Dec 01 19:14:59.325 INFO testing dmerejkowsky/dmenv against master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61 for beta-1.31-5
Dec 01 19:14:59.325 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-1/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt build --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 01 19:14:59.754 INFO [stdout] adc529c5478937b13b75b7327b08007bedb77fd0c165a8c6f58b3d9bf3598a6d
Dec 01 19:14:59.760 INFO running `"docker" "start" "-a" "adc529c5478937b13b75b7327b08007bedb77fd0c165a8c6f58b3d9bf3598a6d"`
Dec 01 19:15:00.895 INFO [stderr] usermod: no changes
Dec 01 19:15:01.091 INFO [stderr]    Compiling appdirs v0.2.0
Dec 01 19:15:01.091 INFO [stderr]    Compiling syn v0.15.17
Dec 01 19:15:15.145 INFO [stderr]    Compiling synstructure v0.10.1
Dec 01 19:15:15.145 INFO [stderr]    Compiling structopt-derive v0.2.12
Dec 01 19:15:15.145 INFO [stderr]    Compiling serde_derive v1.0.80
Dec 01 19:15:24.040 INFO [stderr]    Compiling failure_derive v0.1.3
Dec 01 19:15:24.588 INFO [stderr]    Compiling structopt v0.2.12
Dec 01 19:15:29.743 INFO [stderr]    Compiling failure v0.1.3
Dec 01 19:15:31.495 INFO [stderr]    Compiling which v2.0.0
Dec 01 19:15:41.735 INFO [stderr]    Compiling dmenv v0.6.0 (/source)
Dec 01 19:15:48.643 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 47.72s
Dec 01 19:15:48.655 INFO [stderr] su: No module specific data is present
Dec 01 19:15:49.081 INFO running `"docker" "inspect" "adc529c5478937b13b75b7327b08007bedb77fd0c165a8c6f58b3d9bf3598a6d"`
Dec 01 19:15:49.159 INFO running `"docker" "rm" "-f" "adc529c5478937b13b75b7327b08007bedb77fd0c165a8c6f58b3d9bf3598a6d"`
Dec 01 19:15:49.270 INFO [stdout] adc529c5478937b13b75b7327b08007bedb77fd0c165a8c6f58b3d9bf3598a6d
Dec 01 19:15:49.272 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-1/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen --no-run" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 01 19:15:49.519 INFO [stdout] 038937a17803b60d32aa7ceadd7d8bdbedf526b1c21549760c00932c16e20dd3
Dec 01 19:15:49.524 INFO running `"docker" "start" "-a" "038937a17803b60d32aa7ceadd7d8bdbedf526b1c21549760c00932c16e20dd3"`
Dec 01 19:15:50.274 INFO [stderr] usermod: no changes
Dec 01 19:15:50.366 INFO [stderr]    Compiling dmenv v0.6.0 (/source)
Dec 01 19:15:54.723 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 4.40s
Dec 01 19:15:54.731 INFO [stderr] su: No module specific data is present
Dec 01 19:15:55.777 INFO running `"docker" "inspect" "038937a17803b60d32aa7ceadd7d8bdbedf526b1c21549760c00932c16e20dd3"`
Dec 01 19:15:56.049 INFO running `"docker" "rm" "-f" "038937a17803b60d32aa7ceadd7d8bdbedf526b1c21549760c00932c16e20dd3"`
Dec 01 19:15:56.391 INFO [stdout] 038937a17803b60d32aa7ceadd7d8bdbedf526b1c21549760c00932c16e20dd3
Dec 01 19:15:56.399 INFO running `"docker" "create" "-v" "/mnt/big/crater/work/local/target-dirs/beta-1.31-5/worker-1/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/target:rw,Z" "-v" "/mnt/big/crater/work/local/test-source/worker-1/beta-1.31-5/master#8940af3cea4a9a9deabcaf843b2f8cad9a83fc61:/source:ro,Z" "-v" "/mnt/big/crater/work/local/cargo-home:/cargo-home:ro,Z" "-v" "/mnt/big/crater/work/local/rustup-home:/rustup-home:ro,Z" "-e" "USER_ID=1000" "-e" "SOURCE_DIR=/source" "-e" "USER_ID=1000" "-e" "CMD=cargo +8940af3cea4a9a9deabcaf843b2f8cad9a83fc61-alt test --frozen" "-e" "CARGO_TARGET_DIR=/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=warn" "-e" "CARGO_HOME=/cargo-home" "-e" "RUSTUP_HOME=/rustup-home" "-m" "1536M" "--network" "none" "crater"`
Dec 01 19:15:56.860 INFO [stdout] 73026484e107c9c5613abab98f51dea89e2d3f8b2c3ef8d5dc11d0c1c1b4c195
Dec 01 19:15:56.869 INFO running `"docker" "start" "-a" "73026484e107c9c5613abab98f51dea89e2d3f8b2c3ef8d5dc11d0c1c1b4c195"`
Dec 01 19:15:57.994 INFO [stderr] usermod: no changes
Dec 01 19:15:58.203 INFO [stderr]     Finished dev [unoptimized + debuginfo] target(s) in 0.17s
Dec 01 19:15:58.204 INFO [stderr]      Running /target/debug/deps/dmenv-8d9e8ec4465899e9
Dec 01 19:15:58.215 INFO [stderr]      Running /target/debug/deps/dmenv-50a1ae84bb68f524
Dec 01 19:15:58.215 INFO [stdout] 
Dec 01 19:15:58.215 INFO [stdout] running 0 tests
Dec 01 19:15:58.215 INFO [stdout] 
Dec 01 19:15:58.215 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 01 19:15:58.215 INFO [stdout] 
Dec 01 19:15:58.215 INFO [stdout] 
Dec 01 19:15:58.215 INFO [stdout] running 0 tests
Dec 01 19:15:58.215 INFO [stdout] 
Dec 01 19:15:58.215 INFO [stdout] test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
Dec 01 19:15:58.215 INFO [stdout] 
Dec 01 19:15:58.219 INFO [stderr]      Running /target/debug/deps/integration_tests-560b175a9ccd497a
Dec 01 19:15:58.235 INFO [stdout] 
Dec 01 19:15:58.235 INFO [stdout] running 10 tests
Dec 01 19:15:58.251 INFO [stdout] test run_without_args ... ok
Dec 01 19:15:58.719 INFO [stdout] test lock_complains_if_setup_py_does_not_exist ... ok
Dec 01 19:15:58.830 INFO [stdout] test init_generates_setup_py ... ok
Dec 01 19:15:58.887 INFO [stdout] test run_without_virtualenv ... ok
Dec 01 19:15:58.887 INFO [stdout] test init_does_not_overwrite_existing_setup_py ... ok
Dec 01 19:15:58.931 INFO [stdout] test install_without_lock ... ok
Dec 01 19:15:59.095 INFO [stdout] test show_venv_path ... ok
Dec 01 19:16:03.686 INFO [stderr] The directory '/home/crater/.cache/pip/http' or its parent directory is not owned by the current user and the cache has been disabled. Please check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
Dec 01 19:16:03.695 INFO [stderr] The directory '/home/crater/.cache/pip' or its parent directory is not owned by the current user and caching wheels has been disabled. check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
Dec 01 19:16:03.749 INFO [stderr] Exception:
Dec 01 19:16:03.749 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:03.749 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 137, in _new_conn
Dec 01 19:16:03.749 INFO [stderr]     (self.host, self.port), self.timeout, **extra_kw)
Dec 01 19:16:03.749 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/connection.py", line 67, in create_connection
Dec 01 19:16:03.749 INFO [stderr]     for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM):
Dec 01 19:16:03.749 INFO [stderr]   File "/usr/lib/python3.5/socket.py", line 732, in getaddrinfo
Dec 01 19:16:03.749 INFO [stderr]     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
Dec 01 19:16:03.749 INFO [stderr] socket.gaierror: [Errno -3] Temporary failure in name resolution
Dec 01 19:16:03.749 INFO [stderr] 
Dec 01 19:16:03.749 INFO [stderr] During handling of the above exception, another exception occurred:
Dec 01 19:16:03.749 INFO [stderr] 
Dec 01 19:16:03.749 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:03.749 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 560, in urlopen
Dec 01 19:16:03.749 INFO [stderr]     body=body, headers=headers)
Dec 01 19:16:03.749 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 346, in _make_request
Dec 01 19:16:03.749 INFO [stderr]     self._validate_conn(conn)
Dec 01 19:16:03.749 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 787, in _validate_conn
Dec 01 19:16:03.749 INFO [stderr]     conn.connect()
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 217, in connect
Dec 01 19:16:03.750 INFO [stderr]     conn = self._new_conn()
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 146, in _new_conn
Dec 01 19:16:03.750 INFO [stderr]     self, "Failed to establish a new connection: %s" % e)
Dec 01 19:16:03.750 INFO [stderr] requests.packages.urllib3.exceptions.NewConnectionError: <requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7fabc91b3400>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution
Dec 01 19:16:03.750 INFO [stderr] 
Dec 01 19:16:03.750 INFO [stderr] During handling of the above exception, another exception occurred:
Dec 01 19:16:03.750 INFO [stderr] 
Dec 01 19:16:03.750 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/basecommand.py", line 209, in main
Dec 01 19:16:03.750 INFO [stderr]     status = self.run(options, args)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/commands/install.py", line 317, in run
Dec 01 19:16:03.750 INFO [stderr]     requirement_set.prepare_files(finder)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 360, in prepare_files
Dec 01 19:16:03.750 INFO [stderr]     ignore_dependencies=self.ignore_dependencies))
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 448, in _prepare_file
Dec 01 19:16:03.750 INFO [stderr]     req_to_install, finder)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 397, in _check_skip_installed
Dec 01 19:16:03.750 INFO [stderr]     finder.find_requirement(req_to_install, self.upgrade)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 442, in find_requirement
Dec 01 19:16:03.750 INFO [stderr]     all_candidates = self.find_all_candidates(req.name)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 400, in find_all_candidates
Dec 01 19:16:03.750 INFO [stderr]     for page in self._get_pages(url_locations, project_name):
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 545, in _get_pages
Dec 01 19:16:03.750 INFO [stderr]     page = self._get_page(location)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 648, in _get_page
Dec 01 19:16:03.750 INFO [stderr]     return HTMLPage.get_page(link, session=self.session)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 757, in get_page
Dec 01 19:16:03.750 INFO [stderr]     "Cache-Control": "max-age=600",
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 480, in get
Dec 01 19:16:03.750 INFO [stderr]     return self.request('GET', url, **kwargs)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/lib/python3.5/site-packages/pip/download.py", line 378, in request
Dec 01 19:16:03.750 INFO [stderr]     return super(PipSession, self).request(method, url, *args, **kwargs)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 468, in request
Dec 01 19:16:03.750 INFO [stderr]     resp = self.send(prep, **send_kwargs)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 576, in send
Dec 01 19:16:03.750 INFO [stderr]     r = adapter.send(request, **kwargs)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/CacheControl-0.11.5-py2.py3-none-any.whl/cachecontrol/adapter.py", line 46, in send
Dec 01 19:16:03.750 INFO [stderr]     resp = super(CacheControlAdapter, self).send(request, **kw)
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/adapters.py", line 376, in send
Dec 01 19:16:03.750 INFO [stderr]     timeout=timeout
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 610, in urlopen
Dec 01 19:16:03.750 INFO [stderr]     _stacktrace=sys.exc_info()[2])
Dec 01 19:16:03.750 INFO [stderr]   File "/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/retry.py", line 228, in increment
Dec 01 19:16:03.750 INFO [stderr]     total -= 1
Dec 01 19:16:03.750 INFO [stderr] TypeError: unsupported operand type(s) for -=: 'Retry' and 'int'
Dec 01 19:16:03.830 INFO [stderr] The directory '/home/crater/.cache/pip/http' or its parent directory is not owned by the current user and the cache has been disabled. Please check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
Dec 01 19:16:03.840 INFO [stderr] The directory '/home/crater/.cache/pip' or its parent directory is not owned by the current user and caching wheels has been disabled. check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
Dec 01 19:16:03.927 INFO [stdout] Collecting atomicwrites==1.2.1 (from -r /tmp/test-dmenv.7Ba8A4050TC8/requirements.lock (line 2))
Dec 01 19:16:03.953 INFO [stderr] Exception:
Dec 01 19:16:03.953 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 137, in _new_conn
Dec 01 19:16:03.953 INFO [stderr]     (self.host, self.port), self.timeout, **extra_kw)
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/connection.py", line 67, in create_connection
Dec 01 19:16:03.953 INFO [stderr]     for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM):
Dec 01 19:16:03.953 INFO [stderr]   File "/usr/lib/python3.5/socket.py", line 732, in getaddrinfo
Dec 01 19:16:03.953 INFO [stderr]     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
Dec 01 19:16:03.953 INFO [stderr] socket.gaierror: [Errno -3] Temporary failure in name resolution
Dec 01 19:16:03.953 INFO [stderr] 
Dec 01 19:16:03.953 INFO [stderr] During handling of the above exception, another exception occurred:
Dec 01 19:16:03.953 INFO [stderr] 
Dec 01 19:16:03.953 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 560, in urlopen
Dec 01 19:16:03.953 INFO [stderr]     body=body, headers=headers)
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 346, in _make_request
Dec 01 19:16:03.953 INFO [stderr]     self._validate_conn(conn)
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 787, in _validate_conn
Dec 01 19:16:03.953 INFO [stderr]     conn.connect()
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 217, in connect
Dec 01 19:16:03.953 INFO [stderr]     conn = self._new_conn()
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 146, in _new_conn
Dec 01 19:16:03.953 INFO [stderr]     self, "Failed to establish a new connection: %s" % e)
Dec 01 19:16:03.953 INFO [stderr] requests.packages.urllib3.exceptions.NewConnectionError: <requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7fc757177e10>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution
Dec 01 19:16:03.953 INFO [stderr] 
Dec 01 19:16:03.953 INFO [stderr] During handling of the above exception, another exception occurred:
Dec 01 19:16:03.953 INFO [stderr] 
Dec 01 19:16:03.953 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/basecommand.py", line 209, in main
Dec 01 19:16:03.953 INFO [stderr]     status = self.run(options, args)
Dec 01 19:16:03.953 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/commands/install.py", line 317, in run
Dec 01 19:16:03.953 INFO [stderr]     requirement_set.prepare_files(finder)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 360, in prepare_files
Dec 01 19:16:03.954 INFO [stderr]     ignore_dependencies=self.ignore_dependencies))
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 512, in _prepare_file
Dec 01 19:16:03.954 INFO [stderr]     finder, self.upgrade, require_hashes)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_install.py", line 273, in populate_link
Dec 01 19:16:03.954 INFO [stderr]     self.link = finder.find_requirement(self, upgrade)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 442, in find_requirement
Dec 01 19:16:03.954 INFO [stderr]     all_candidates = self.find_all_candidates(req.name)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 400, in find_all_candidates
Dec 01 19:16:03.954 INFO [stderr]     for page in self._get_pages(url_locations, project_name):
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 545, in _get_pages
Dec 01 19:16:03.954 INFO [stderr]     page = self._get_page(location)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 648, in _get_page
Dec 01 19:16:03.954 INFO [stderr]     return HTMLPage.get_page(link, session=self.session)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 757, in get_page
Dec 01 19:16:03.954 INFO [stderr]     "Cache-Control": "max-age=600",
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 480, in get
Dec 01 19:16:03.954 INFO [stderr]     return self.request('GET', url, **kwargs)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/lib/python3.5/site-packages/pip/download.py", line 378, in request
Dec 01 19:16:03.954 INFO [stderr]     return super(PipSession, self).request(method, url, *args, **kwargs)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 468, in request
Dec 01 19:16:03.954 INFO [stderr]     resp = self.send(prep, **send_kwargs)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 576, in send
Dec 01 19:16:03.954 INFO [stderr]     r = adapter.send(request, **kwargs)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/CacheControl-0.11.5-py2.py3-none-any.whl/cachecontrol/adapter.py", line 46, in send
Dec 01 19:16:03.954 INFO [stderr]     resp = super(CacheControlAdapter, self).send(request, **kw)
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/adapters.py", line 376, in send
Dec 01 19:16:03.954 INFO [stderr]     timeout=timeout
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 610, in urlopen
Dec 01 19:16:03.954 INFO [stderr]     _stacktrace=sys.exc_info()[2])
Dec 01 19:16:03.954 INFO [stderr]   File "/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/retry.py", line 228, in increment
Dec 01 19:16:03.954 INFO [stderr]     total -= 1
Dec 01 19:16:03.954 INFO [stderr] TypeError: unsupported operand type(s) for -=: 'Retry' and 'int'
Dec 01 19:16:04.059 INFO [stdout] test lock_workflow ... FAILED
Dec 01 19:16:04.166 INFO [stdout] test install_workflow_step_by_step ... FAILED
Dec 01 19:16:04.695 INFO [stderr] The directory '/home/crater/.cache/pip/http' or its parent directory is not owned by the current user and the cache has been disabled. Please check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
Dec 01 19:16:04.695 INFO [stderr] The directory '/home/crater/.cache/pip' or its parent directory is not owned by the current user and caching wheels has been disabled. check the permissions and owner of that directory. If executing pip with sudo, you may want sudo's -H flag.
Dec 01 19:16:04.739 INFO [stderr] Exception:
Dec 01 19:16:04.739 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 137, in _new_conn
Dec 01 19:16:04.739 INFO [stderr]     (self.host, self.port), self.timeout, **extra_kw)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/connection.py", line 67, in create_connection
Dec 01 19:16:04.739 INFO [stderr]     for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM):
Dec 01 19:16:04.739 INFO [stderr]   File "/usr/lib/python3.5/socket.py", line 732, in getaddrinfo
Dec 01 19:16:04.739 INFO [stderr]     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
Dec 01 19:16:04.739 INFO [stderr] socket.gaierror: [Errno -3] Temporary failure in name resolution
Dec 01 19:16:04.739 INFO [stderr] 
Dec 01 19:16:04.739 INFO [stderr] During handling of the above exception, another exception occurred:
Dec 01 19:16:04.739 INFO [stderr] 
Dec 01 19:16:04.739 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 560, in urlopen
Dec 01 19:16:04.739 INFO [stderr]     body=body, headers=headers)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 346, in _make_request
Dec 01 19:16:04.739 INFO [stderr]     self._validate_conn(conn)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 787, in _validate_conn
Dec 01 19:16:04.739 INFO [stderr]     conn.connect()
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 217, in connect
Dec 01 19:16:04.739 INFO [stderr]     conn = self._new_conn()
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connection.py", line 146, in _new_conn
Dec 01 19:16:04.739 INFO [stderr]     self, "Failed to establish a new connection: %s" % e)
Dec 01 19:16:04.739 INFO [stderr] requests.packages.urllib3.exceptions.NewConnectionError: <requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7efd72c10710>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution
Dec 01 19:16:04.739 INFO [stderr] 
Dec 01 19:16:04.739 INFO [stderr] During handling of the above exception, another exception occurred:
Dec 01 19:16:04.739 INFO [stderr] 
Dec 01 19:16:04.739 INFO [stderr] Traceback (most recent call last):
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/basecommand.py", line 209, in main
Dec 01 19:16:04.739 INFO [stderr]     status = self.run(options, args)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/commands/install.py", line 317, in run
Dec 01 19:16:04.739 INFO [stderr]     requirement_set.prepare_files(finder)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 360, in prepare_files
Dec 01 19:16:04.739 INFO [stderr]     ignore_dependencies=self.ignore_dependencies))
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 448, in _prepare_file
Dec 01 19:16:04.739 INFO [stderr]     req_to_install, finder)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/req/req_set.py", line 397, in _check_skip_installed
Dec 01 19:16:04.739 INFO [stderr]     finder.find_requirement(req_to_install, self.upgrade)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 442, in find_requirement
Dec 01 19:16:04.739 INFO [stderr]     all_candidates = self.find_all_candidates(req.name)
Dec 01 19:16:04.739 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 400, in find_all_candidates
Dec 01 19:16:04.740 INFO [stderr]     for page in self._get_pages(url_locations, project_name):
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 545, in _get_pages
Dec 01 19:16:04.740 INFO [stderr]     page = self._get_page(location)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 648, in _get_page
Dec 01 19:16:04.740 INFO [stderr]     return HTMLPage.get_page(link, session=self.session)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/index.py", line 757, in get_page
Dec 01 19:16:04.740 INFO [stderr]     "Cache-Control": "max-age=600",
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 480, in get
Dec 01 19:16:04.740 INFO [stderr]     return self.request('GET', url, **kwargs)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/lib/python3.5/site-packages/pip/download.py", line 378, in request
Dec 01 19:16:04.740 INFO [stderr]     return super(PipSession, self).request(method, url, *args, **kwargs)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 468, in request
Dec 01 19:16:04.740 INFO [stderr]     resp = self.send(prep, **send_kwargs)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/sessions.py", line 576, in send
Dec 01 19:16:04.740 INFO [stderr]     r = adapter.send(request, **kwargs)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/CacheControl-0.11.5-py2.py3-none-any.whl/cachecontrol/adapter.py", line 46, in send
Dec 01 19:16:04.740 INFO [stderr]     resp = super(CacheControlAdapter, self).send(request, **kw)
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/requests-2.9.1-py2.py3-none-any.whl/requests/adapters.py", line 376, in send
Dec 01 19:16:04.740 INFO [stderr]     timeout=timeout
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/connectionpool.py", line 610, in urlopen
Dec 01 19:16:04.740 INFO [stderr]     _stacktrace=sys.exc_info()[2])
Dec 01 19:16:04.740 INFO [stderr]   File "/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/share/python-wheels/urllib3-1.13.1-py2.py3-none-any.whl/urllib3/util/retry.py", line 228, in increment
Dec 01 19:16:04.740 INFO [stderr]     total -= 1
Dec 01 19:16:04.740 INFO [stderr] TypeError: unsupported operand type(s) for -=: 'Retry' and 'int'
Dec 01 19:16:04.848 INFO [stderr] error: test failed, to rerun pass '--test integration_tests'
Dec 01 19:16:04.848 INFO [stdout] test install_workflow_all_in_one ... FAILED
Dec 01 19:16:04.848 INFO [stderr] su: No module specific data is present
Dec 01 19:16:04.848 INFO [stdout] 
Dec 01 19:16:04.848 INFO [stdout] failures:
Dec 01 19:16:04.848 INFO [stdout] 
Dec 01 19:16:04.848 INFO [stdout] ---- lock_workflow stdout ----
Dec 01 19:16:04.848 INFO [stdout] [34m::[0m Creating virtualenv in: /tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2
Dec 01 19:16:04.848 INFO [stdout] [34m->[0m running [1m/usr/bin/python3[0m -m venv /tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2
Dec 01 19:16:04.848 INFO [stdout] [34m->[0m running [1m/tmp/test-dmenv.Ehvitjmj0uDK/.venv/3.5.2/bin/python[0m -m pip install pip --upgrade
Dec 01 19:16:04.848 INFO [stdout] thread 'lock_workflow' panicked at ': Error { description: "command failed" }', libcore/result.rs:1009:5
Dec 01 19:16:04.848 INFO [stdout] stack backtrace:
Dec 01 19:16:04.848 INFO [stdout]    0:     0x5607399c7b2f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h3a8b83e1922cbdde
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 01 19:16:04.848 INFO [stdout]    1:     0x5607399d4b07 - std::sys_common::backtrace::print::h00d3155a29b4020f
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 01 19:16:04.848 INFO [stdout]    2:     0x5607399cd42f - std::panicking::default_hook::{{closure}}::hd7465c742e79e1bb
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:211
Dec 01 19:16:04.848 INFO [stdout]    3:     0x5607399cd12e - std::panicking::default_hook::h9e3966f2aa2a6e12
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:221
Dec 01 19:16:04.848 INFO [stdout]    4:     0x5607399cdb0e - std::panicking::rust_panic_with_hook::h587f091ae747d080
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:476
Dec 01 19:16:04.848 INFO [stdout]    5:     0x5607399cd6b1 - std::panicking::continue_panic_fmt::hb3a4fdede87f43a8
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:390
Dec 01 19:16:04.848 INFO [stdout]    6:     0x5607399cd595 - rust_begin_unwind
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:325
Dec 01 19:16:04.848 INFO [stdout]    7:     0x560739a1286c - core::panicking::panic_fmt::h6f9cebf5e7474a0b
Dec 01 19:16:04.848 INFO [stdout]                                at libcore/panicking.rs:77
Dec 01 19:16:04.848 INFO [stdout]    8:     0x5607397310eb - core::result::unwrap_failed::hf3f3fe95b9e8a6d6
Dec 01 19:16:04.848 INFO [stdout]                                at libcore/macros.rs:26
Dec 01 19:16:04.848 INFO [stdout]    9:     0x560739730006 - <core::result::Result<T, E>>::expect::h29b9b0364062ff88
Dec 01 19:16:04.848 INFO [stdout]                                at libcore/result.rs:835
Dec 01 19:16:04.848 INFO [stdout]   10:     0x56073973a126 - integration_tests::helpers::TestApp::assert_run_ok::haba407613252d8a6
Dec 01 19:16:04.848 INFO [stdout]                                at tests/helpers/mod.rs:57
Dec 01 19:16:04.848 INFO [stdout]   11:     0x560739734207 - integration_tests::lock_workflow::h600f4db2eb60bc32
Dec 01 19:16:04.848 INFO [stdout]                                at tests/integration_tests.rs:53
Dec 01 19:16:04.848 INFO [stdout]   12:     0x5607397340d9 - integration_tests::lock_workflow::{{closure}}::h3c577d1b9f574ac9
Dec 01 19:16:04.848 INFO [stdout]                                at tests/integration_tests.rs:50
Dec 01 19:16:04.848 INFO [stdout]   13:     0x56073972d82d - core::ops::function::FnOnce::call_once::h5a4ce08a1ab43cbe
Dec 01 19:16:04.848 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 19:16:04.848 INFO [stdout]   14:     0x56073973e11e - <F as alloc::boxed::FnBox<A>>::call_box::hac903f91577a156c
Dec 01 19:16:04.848 INFO [stdout]                                at libtest/lib.rs:1468
Dec 01 19:16:04.848 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 19:16:04.848 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 01 19:16:04.848 INFO [stdout]   15:     0x5607399dfab9 - __rust_maybe_catch_panic
Dec 01 19:16:04.848 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 01 19:16:04.848 INFO [stdout]   16:     0x56073975fd72 - std::sys_common::backtrace::__rust_begin_short_backtrace::hb8f0d0309526c184
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 19:16:04.848 INFO [stdout]                                at libtest/lib.rs:1423
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 01 19:16:04.848 INFO [stdout]   17:     0x560739760824 - std::panicking::try::do_call::hc2f7c8b9a348d8db
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panic.rs:313
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:310
Dec 01 19:16:04.848 INFO [stdout]   18:     0x5607399dfab9 - __rust_maybe_catch_panic
Dec 01 19:16:04.848 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 01 19:16:04.848 INFO [stdout]   19:     0x56073974da5c - <F as alloc::boxed::FnBox<A>>::call_box::h6bfded618e480b32
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 01 19:16:04.848 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 01 19:16:04.848 INFO [stdout]   20:     0x5607399ca2ad - std::sys_common::thread::start_thread::h4c28257d67cdf9cb
Dec 01 19:16:04.848 INFO [stdout]                                at liballoc/boxed.rs:682
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 01 19:16:04.848 INFO [stdout]   21:     0x5607399bc3a5 - std::sys::unix::thread::Thread::new::thread_start::hfecb2e7eff8fd34f
Dec 01 19:16:04.848 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 01 19:16:04.848 INFO [stdout]   22:     0x7fdde085b6b9 - start_thread
Dec 01 19:16:04.848 INFO [stdout]   23:     0x7fdde037b41c - clone
Dec 01 19:16:04.848 INFO [stdout]   24:                0x0 - <unknown>
Dec 01 19:16:04.848 INFO [stdout] 
Dec 01 19:16:04.848 INFO [stdout] ---- install_workflow_step_by_step stdout ----
Dec 01 19:16:04.848 INFO [stdout] [34m::[0m Creating virtualenv in: /tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2
Dec 01 19:16:04.848 INFO [stdout] [34m->[0m running [1m/usr/bin/python3[0m -m venv /tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2
Dec 01 19:16:04.848 INFO [stdout] [34m->[0m running [1m/tmp/test-dmenv.7Ba8A4050TC8/.venv/3.5.2/bin/pip[0m install --requirement /tmp/test-dmenv.7Ba8A4050TC8/requirements.lock
Dec 01 19:16:04.848 INFO [stdout] thread 'install_workflow_step_by_step' panicked at ': Error { description: "command failed" }', libcore/result.rs:1009:5
Dec 01 19:16:04.848 INFO [stdout] stack backtrace:
Dec 01 19:16:04.848 INFO [stdout]    0:     0x5607399c7b2f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h3a8b83e1922cbdde
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 01 19:16:04.849 INFO [stdout]    1:     0x5607399d4b07 - std::sys_common::backtrace::print::h00d3155a29b4020f
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 01 19:16:04.849 INFO [stdout]    2:     0x5607399cd42f - std::panicking::default_hook::{{closure}}::hd7465c742e79e1bb
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:211
Dec 01 19:16:04.849 INFO [stdout]    3:     0x5607399cd12e - std::panicking::default_hook::h9e3966f2aa2a6e12
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:221
Dec 01 19:16:04.849 INFO [stdout]    4:     0x5607399cdb0e - std::panicking::rust_panic_with_hook::h587f091ae747d080
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:476
Dec 01 19:16:04.849 INFO [stdout]    5:     0x5607399cd6b1 - std::panicking::continue_panic_fmt::hb3a4fdede87f43a8
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:390
Dec 01 19:16:04.849 INFO [stdout]    6:     0x5607399cd595 - rust_begin_unwind
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:325
Dec 01 19:16:04.849 INFO [stdout]    7:     0x560739a1286c - core::panicking::panic_fmt::h6f9cebf5e7474a0b
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/panicking.rs:77
Dec 01 19:16:04.849 INFO [stdout]    8:     0x5607397310eb - core::result::unwrap_failed::hf3f3fe95b9e8a6d6
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/macros.rs:26
Dec 01 19:16:04.849 INFO [stdout]    9:     0x560739730006 - <core::result::Result<T, E>>::expect::h29b9b0364062ff88
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/result.rs:835
Dec 01 19:16:04.849 INFO [stdout]   10:     0x56073973a126 - integration_tests::helpers::TestApp::assert_run_ok::haba407613252d8a6
Dec 01 19:16:04.849 INFO [stdout]                                at tests/helpers/mod.rs:57
Dec 01 19:16:04.849 INFO [stdout]   11:     0x5607397347f2 - integration_tests::install_workflow_step_by_step::h2ff5924319d956be
Dec 01 19:16:04.849 INFO [stdout]                                at tests/integration_tests.rs:77
Dec 01 19:16:04.849 INFO [stdout]   12:     0x560739734679 - integration_tests::install_workflow_step_by_step::{{closure}}::haf20eb3e0458f8ff
Dec 01 19:16:04.849 INFO [stdout]                                at tests/integration_tests.rs:72
Dec 01 19:16:04.849 INFO [stdout]   13:     0x56073972d7ed - core::ops::function::FnOnce::call_once::h5807a96fd24d86ce
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 19:16:04.849 INFO [stdout]   14:     0x56073973e11e - <F as alloc::boxed::FnBox<A>>::call_box::hac903f91577a156c
Dec 01 19:16:04.849 INFO [stdout]                                at libtest/lib.rs:1468
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 19:16:04.849 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 01 19:16:04.849 INFO [stdout]   15:     0x5607399dfab9 - __rust_maybe_catch_panic
Dec 01 19:16:04.849 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 01 19:16:04.849 INFO [stdout]   16:     0x56073975fd72 - std::sys_common::backtrace::__rust_begin_short_backtrace::hb8f0d0309526c184
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 19:16:04.849 INFO [stdout]                                at libtest/lib.rs:1423
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 01 19:16:04.849 INFO [stdout]   17:     0x560739760824 - std::panicking::try::do_call::hc2f7c8b9a348d8db
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panic.rs:313
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:310
Dec 01 19:16:04.849 INFO [stdout]   18:     0x5607399dfab9 - __rust_maybe_catch_panic
Dec 01 19:16:04.849 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 01 19:16:04.849 INFO [stdout]   19:     0x56073974da5c - <F as alloc::boxed::FnBox<A>>::call_box::h6bfded618e480b32
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 01 19:16:04.849 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 01 19:16:04.849 INFO [stdout]   20:     0x5607399ca2ad - std::sys_common::thread::start_thread::h4c28257d67cdf9cb
Dec 01 19:16:04.849 INFO [stdout]                                at liballoc/boxed.rs:682
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 01 19:16:04.849 INFO [stdout]   21:     0x5607399bc3a5 - std::sys::unix::thread::Thread::new::thread_start::hfecb2e7eff8fd34f
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 01 19:16:04.849 INFO [stdout]   22:     0x7fdde085b6b9 - start_thread
Dec 01 19:16:04.849 INFO [stdout]   23:     0x7fdde037b41c - clone
Dec 01 19:16:04.849 INFO [stdout]   24:                0x0 - <unknown>
Dec 01 19:16:04.849 INFO [stdout] 
Dec 01 19:16:04.849 INFO [stdout] ---- install_workflow_all_in_one stdout ----
Dec 01 19:16:04.849 INFO [stdout] [34m::[0m Creating virtualenv in: /tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2
Dec 01 19:16:04.849 INFO [stdout] [34m->[0m running [1m/usr/bin/python3[0m -m venv /tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2
Dec 01 19:16:04.849 INFO [stdout] [34m->[0m running [1m/tmp/test-dmenv.MooEMU07WNUk/.venv/3.5.2/bin/python[0m -m pip install pip --upgrade
Dec 01 19:16:04.849 INFO [stdout] thread 'install_workflow_all_in_one' panicked at ': Error { description: "command failed" }', libcore/result.rs:1009:5
Dec 01 19:16:04.849 INFO [stdout] stack backtrace:
Dec 01 19:16:04.849 INFO [stdout]    0:     0x5607399c7b2f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h3a8b83e1922cbdde
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Dec 01 19:16:04.849 INFO [stdout]    1:     0x5607399d4b07 - std::sys_common::backtrace::print::h00d3155a29b4020f
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys_common/backtrace.rs:71
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/sys_common/backtrace.rs:59
Dec 01 19:16:04.849 INFO [stdout]    2:     0x5607399cd42f - std::panicking::default_hook::{{closure}}::hd7465c742e79e1bb
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:211
Dec 01 19:16:04.849 INFO [stdout]    3:     0x5607399cd12e - std::panicking::default_hook::h9e3966f2aa2a6e12
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:221
Dec 01 19:16:04.849 INFO [stdout]    4:     0x5607399cdb0e - std::panicking::rust_panic_with_hook::h587f091ae747d080
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:476
Dec 01 19:16:04.849 INFO [stdout]    5:     0x5607399cd6b1 - std::panicking::continue_panic_fmt::hb3a4fdede87f43a8
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:390
Dec 01 19:16:04.849 INFO [stdout]    6:     0x5607399cd595 - rust_begin_unwind
Dec 01 19:16:04.849 INFO [stdout]                                at libstd/panicking.rs:325
Dec 01 19:16:04.849 INFO [stdout]    7:     0x560739a1286c - core::panicking::panic_fmt::h6f9cebf5e7474a0b
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/panicking.rs:77
Dec 01 19:16:04.849 INFO [stdout]    8:     0x5607397310eb - core::result::unwrap_failed::hf3f3fe95b9e8a6d6
Dec 01 19:16:04.849 INFO [stdout]                                at libcore/macros.rs:26
Dec 01 19:16:04.850 INFO [stdout]    9:     0x560739730006 - <core::result::Result<T, E>>::expect::h29b9b0364062ff88
Dec 01 19:16:04.850 INFO [stdout]                                at libcore/result.rs:835
Dec 01 19:16:04.850 INFO [stdout]   10:     0x56073973a126 - integration_tests::helpers::TestApp::assert_run_ok::haba407613252d8a6
Dec 01 19:16:04.850 INFO [stdout]                                at tests/helpers/mod.rs:57
Dec 01 19:16:04.850 INFO [stdout]   11:     0x56073973461a - integration_tests::install_workflow_all_in_one::h87e3292aa41b381d
Dec 01 19:16:04.850 INFO [stdout]                                at tests/integration_tests.rs:68
Dec 01 19:16:04.850 INFO [stdout]   12:     0x5607397344c9 - integration_tests::install_workflow_all_in_one::{{closure}}::hd3f129a0f3f60c94
Dec 01 19:16:04.850 INFO [stdout]                                at tests/integration_tests.rs:63
Dec 01 19:16:04.850 INFO [stdout]   13:     0x56073972d86d - core::ops::function::FnOnce::call_once::h5e389bbcd91179ef
Dec 01 19:16:04.850 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 19:16:04.850 INFO [stdout]   14:     0x56073973e11e - <F as alloc::boxed::FnBox<A>>::call_box::hac903f91577a156c
Dec 01 19:16:04.850 INFO [stdout]                                at libtest/lib.rs:1468
Dec 01 19:16:04.850 INFO [stdout]                                at libcore/ops/function.rs:238
Dec 01 19:16:04.850 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 01 19:16:04.850 INFO [stdout]   15:     0x5607399dfab9 - __rust_maybe_catch_panic
Dec 01 19:16:04.850 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 01 19:16:04.850 INFO [stdout]   16:     0x56073975fd72 - std::sys_common::backtrace::__rust_begin_short_backtrace::hb8f0d0309526c184
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 19:16:04.850 INFO [stdout]                                at libtest/lib.rs:1423
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/sys_common/backtrace.rs:136
Dec 01 19:16:04.850 INFO [stdout]   17:     0x560739760824 - std::panicking::try::do_call::hc2f7c8b9a348d8db
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/thread/mod.rs:409
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/panic.rs:313
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/panicking.rs:310
Dec 01 19:16:04.850 INFO [stdout]   18:     0x5607399dfab9 - __rust_maybe_catch_panic
Dec 01 19:16:04.850 INFO [stdout]                                at libpanic_unwind/lib.rs:102
Dec 01 19:16:04.850 INFO [stdout]   19:     0x56073974da5c - <F as alloc::boxed::FnBox<A>>::call_box::h6bfded618e480b32
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/panicking.rs:289
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/panic.rs:392
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/thread/mod.rs:408
Dec 01 19:16:04.850 INFO [stdout]                                at liballoc/boxed.rs:672
Dec 01 19:16:04.850 INFO [stdout]   20:     0x5607399ca2ad - std::sys_common::thread::start_thread::h4c28257d67cdf9cb
Dec 01 19:16:04.850 INFO [stdout]                                at liballoc/boxed.rs:682
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/sys_common/thread.rs:24
Dec 01 19:16:04.850 INFO [stdout]   21:     0x5607399bc3a5 - std::sys::unix::thread::Thread::new::thread_start::hfecb2e7eff8fd34f
Dec 01 19:16:04.850 INFO [stdout]                                at libstd/sys/unix/thread.rs:90
Dec 01 19:16:04.850 INFO [stdout]   22:     0x7fdde085b6b9 - start_thread
Dec 01 19:16:04.850 INFO [stdout]   23:     0x7fdde037b41c - clone
Dec 01 19:16:04.850 INFO [stdout]   24:                0x0 - <unknown>
Dec 01 19:16:04.850 INFO [stdout] 
Dec 01 19:16:04.850 INFO [stdout] 
Dec 01 19:16:04.850 INFO [stdout] failures:
Dec 01 19:16:04.850 INFO [stdout]     install_workflow_all_in_one
Dec 01 19:16:04.850 INFO [stdout]     install_workflow_step_by_step
Dec 01 19:16:04.850 INFO [stdout]     lock_workflow
Dec 01 19:16:04.850 INFO [stdout] 
Dec 01 19:16:04.850 INFO [stdout] test result: FAILED. 7 passed; 3 failed; 0 ignored; 0 measured; 0 filtered out
Dec 01 19:16:04.850 INFO [stdout] 
Dec 01 19:16:05.814 INFO running `"docker" "inspect" "73026484e107c9c5613abab98f51dea89e2d3f8b2c3ef8d5dc11d0c1c1b4c195"`
Dec 01 19:16:06.133 INFO running `"docker" "rm" "-f" "73026484e107c9c5613abab98f51dea89e2d3f8b2c3ef8d5dc11d0c1c1b4c195"`
Dec 01 19:16:06.438 INFO [stdout] 73026484e107c9c5613abab98f51dea89e2d3f8b2c3ef8d5dc11d0c1c1b4c195
